[INFO] fetching crate wl-proxy 0.1.2...
[INFO] testing wl-proxy-0.1.2 against master#1f7f8ea0721a3b1eb73e6c6d25cccb371434b320 for pr-154065-1
[INFO] extracting crate wl-proxy 0.1.2 into /workspace/builds/worker-1-tc1/source
[INFO] started tweaking crates.io crate wl-proxy 0.1.2
[INFO] finished tweaking crates.io crate wl-proxy 0.1.2
[INFO] tweaked toml for crates.io crate wl-proxy 0.1.2 written to /workspace/builds/worker-1-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate wl-proxy 0.1.2 on toolchain 1f7f8ea0721a3b1eb73e6c6d25cccb371434b320
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1f7f8ea0721a3b1eb73e6c6d25cccb371434b320" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wl-proxy 0.1.2 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1f7f8ea0721a3b1eb73e6c6d25cccb371434b320" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded debug-fn v1.0.0
[INFO] [stderr]   Downloaded run-on-drop v1.0.0
[INFO] [stderr]   Downloaded uapi-proc v0.0.5
[INFO] [stderr]   Downloaded linearize v0.1.5
[INFO] [stderr]   Downloaded linearize-derive v0.2.1
[INFO] [stderr]   Downloaded uapi v0.2.13
[INFO] [stderr]   Downloaded error_reporter v1.0.0
[INFO] [stderr]   Downloaded isnt v0.2.0
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1f7f8ea0721a3b1eb73e6c6d25cccb371434b320" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 1a20a41df3f15fccb90fa1d293fe5db2345e534d2d665b3081c52707295adb5c
[INFO] running `Command { std: "docker" "start" "-a" "1a20a41df3f15fccb90fa1d293fe5db2345e534d2d665b3081c52707295adb5c", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "1a20a41df3f15fccb90fa1d293fe5db2345e534d2d665b3081c52707295adb5c", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "1a20a41df3f15fccb90fa1d293fe5db2345e534d2d665b3081c52707295adb5c", kill_on_drop: false }`
[INFO] [stdout] 1a20a41df3f15fccb90fa1d293fe5db2345e534d2d665b3081c52707295adb5c
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1f7f8ea0721a3b1eb73e6c6d25cccb371434b320" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 09abc89c0d2ae04a76b5e2e0d53d6bedda1ced33a21afceb28f7b84053254e7e
[INFO] running `Command { std: "docker" "start" "-a" "09abc89c0d2ae04a76b5e2e0d53d6bedda1ced33a21afceb28f7b84053254e7e", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling phf_shared v0.13.1
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling syn v2.0.111
[INFO] [stderr]    Compiling linearize v0.1.5
[INFO] [stderr]    Compiling syn v1.0.109
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling run-on-drop v1.0.0
[INFO] [stderr]    Compiling isnt v0.2.0
[INFO] [stderr]    Compiling phf_generator v0.13.1
[INFO] [stderr]    Compiling error_reporter v1.0.0
[INFO] [stderr]    Compiling debug-fn v1.0.0
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling linearize-derive v0.2.1
[INFO] [stderr]    Compiling phf_macros v0.13.1
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[INFO] [stderr]    Compiling phf v0.13.1
[INFO] [stderr]    Compiling wl-proxy v0.1.2 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 18.01s
[INFO] running `Command { std: "docker" "inspect" "09abc89c0d2ae04a76b5e2e0d53d6bedda1ced33a21afceb28f7b84053254e7e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "09abc89c0d2ae04a76b5e2e0d53d6bedda1ced33a21afceb28f7b84053254e7e", kill_on_drop: false }`
[INFO] [stdout] 09abc89c0d2ae04a76b5e2e0d53d6bedda1ced33a21afceb28f7b84053254e7e
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1f7f8ea0721a3b1eb73e6c6d25cccb371434b320" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 7d0ac03e9f9d922e627174741b1ea1458aa5df92ce52f2ab85bf0cc3ea73bb7f
[INFO] running `Command { std: "docker" "start" "-a" "7d0ac03e9f9d922e627174741b1ea1458aa5df92ce52f2ab85bf0cc3ea73bb7f", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling anstream v0.6.21
[INFO] [stderr]    Compiling jiff v0.2.16
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling env_filter v0.1.4
[INFO] [stderr]    Compiling wl-proxy v0.1.2 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling env_logger v0.11.8
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 25.36s
[INFO] running `Command { std: "docker" "inspect" "7d0ac03e9f9d922e627174741b1ea1458aa5df92ce52f2ab85bf0cc3ea73bb7f", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "7d0ac03e9f9d922e627174741b1ea1458aa5df92ce52f2ab85bf0cc3ea73bb7f", kill_on_drop: false }`
[INFO] [stdout] 7d0ac03e9f9d922e627174741b1ea1458aa5df92ce52f2ab85bf0cc3ea73bb7f
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1f7f8ea0721a3b1eb73e6c6d25cccb371434b320" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] a2d9861e0002815a2b26e65667e1a9d249ea8f58b0935219b20ad392688887eb
[INFO] running `Command { std: "docker" "start" "-a" "a2d9861e0002815a2b26e65667e1a9d249ea8f58b0935219b20ad392688887eb", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.09s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/wl_proxy-c279e5984628a866)
[INFO] [stdout] 
[INFO] [stdout] running 111 tests
[INFO] [stderr] [1878410.505] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878410.776] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878410.945] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.076] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.162] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.188] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.242] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.487] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.503] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878411.545] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.584] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.693] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.763] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.799] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.815] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.828] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.842] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.512] {client} server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1878411.865] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1878411.895] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878411.926] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.949] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878411.964] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.975] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878411.999] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878412.006] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878412.034] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878412.040] {proxy } client#2    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1878412.054] {proxy } server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1878412.059] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1878412.066] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stdout] test client::tests::disconnected ... ok
[INFO] [stderr] [1878412.479] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878412.545] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878412.632] {server} client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878412.637] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878412.652] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878412.652] {server} client#2    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1878412.658] {server} client#2    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1878412.664] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878412.675] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878412.676] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878412.682] {server} client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1878412.688] {server} client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878412.692] {server} client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878412.766] {proxy } server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1878412.771] {proxy } client#2    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1878412.786] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878412.791] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878412.798] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878412.800] {proxy } client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878412.804] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878412.808] {proxy } client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878412.837] {client} server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1878412.842] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878412.846] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878412.849] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878413.072] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878413.169] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:25:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [1878413.424] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878413.667] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878413.684] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878413.709] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878413.721] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878413.731] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878413.743] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878413.765] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:25:53Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.65535 message: unknown message id 65535
[INFO] [stdout] test client::tests::unset_handler ... ok
[INFO] [stderr] [1878414.414] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test endpoint::tests::lookup ... ok
[INFO] [stderr] [1878414.440] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878414.474] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878414.487] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878414.500] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878414.513] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878414.580] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878414.591] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878414.619] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878414.625] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#5)
[INFO] [stderr] [1878414.643] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878415.448] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test endpoint::tests::test ... ok
[INFO] [stderr] [1878415.470] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test endpoint::tests::invalid_message ... ok
[INFO] [stderr] [1878415.498] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::debug ... ok
[INFO] [stderr] [1878415.512] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::display ... ok
[INFO] [stderr] [1878415.520] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::from_f32 ... ok
[INFO] [stderr] [1878415.533] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test endpoint::tests::dispatch_destroyed ... ok
[INFO] [stdout] test fixed::tests::from_i32 ... ok
[INFO] [stdout] test fixed::tests::from_i64 ... ok
[INFO] [stdout] test client::tests::objects ... ok
[INFO] [stdout] test fixed::tests::from_ints ... ok
[INFO] [stdout] test fixed::tests::minima ... ok
[INFO] [stdout] test fixed::tests::test_shiftops ... ok
[INFO] [stdout] test fixed::tests::to_f32 ... ok
[INFO] [stdout] test fixed::tests::to_i32_ceil ... ok
[INFO] [stdout] test fixed::tests::test_unops ... ok
[INFO] [stdout] test fixed::tests::to_i32_floor ... ok
[INFO] [stdout] test fixed::tests::to_i32_nearest ... ok
[INFO] [stdout] test fixed::tests::to_i32_zero ... ok
[INFO] [stdout] test fixed::tests::wire ... ok
[INFO] [stdout] test global_mapper::tests::test ... ok
[INFO] [stdout] test global_mapper::tests::test_default ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Could not add synthetic global: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind ... ok
[INFO] [stdout] test fixed::tests::one_two ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Could not handle client bind: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_bind_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global ... ok
[INFO] [stdout] test fixed::tests::test_binops ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Could not handle server global: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_ignored ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stdout] test global_mapper::tests::test_forward_bind_synthetic ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Could not handle server global remove: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Could not remove synthetic global: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_ignore_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_error ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stdout] test global_mapper::tests::test_try_forward_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_error ... ok
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_synthetic ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_ignored ... ok
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global_error ... ok
[INFO] [stdout] test handler::tests::borrow ... ok
[INFO] [stdout] test handler::tests::clone ... ok
[INFO] [stderr] [1878438.978] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.000] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.032] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.042] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.059] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.099] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test handler::tests::map ... ok
[INFO] [stdout] test handler::tests::replace ... ok
[INFO] [stdout] test object::tests::client ... ok
[INFO] [stdout] test object::tests::client_id ... ok
[INFO] [stderr] [1878439.605] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.623] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.652] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.661] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.669] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.682] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.739] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.753] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.766] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.780] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.780] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.790] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.797] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.809] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.853] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878439.853] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878439.861] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878439.866] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878439.891] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878439.912] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878439.917] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878439.923] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878440.009] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878440.032] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878440.153] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878440.169] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878440.176] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878440.221] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878440.287] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878440.292] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878440.306] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878440.311] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878440.317] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878440.319] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878440.323] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878440.327] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test object::tests::double_send ... ok
[INFO] [stderr] [1878440.350] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test object::tests::duplicate_client_id ... ok
[INFO] [stderr] [1878440.357] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878440.362] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878440.365] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878440.459] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.470] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.495] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.504] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.511] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.524] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.546] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.555] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.588] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878440.595] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878440.619] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878440.632] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878440.637] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2026-03-30T09:25:53Z ERROR wl_proxy::state] Could not handle client message: could not handle a wlproxy_test#3.create_dummy message: could not assign client id 4 to argument id: the client id 4 is already in use
[INFO] [stderr] [1878440.757] {server} client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1878440.792] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.804] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.826] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.833] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.846] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.857] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.871] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878440.887] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4294967295)
[INFO] [stderr] [1878440.912] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.931] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878440.957] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.965] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878440.971] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-03-30T09:25:53Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.sync message: could not assign client id 4294967295 to argument callback: the id 4294967295 is too large to be a client id
[INFO] [stderr] [1878440.984] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.004] {proxy } client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stdout] test object::tests::client_object_with_server_id ... ok
[INFO] [stderr] [1878441.300] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.313] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.391] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.418] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.452] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.467] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.481] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.507] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.534] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.544] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.639] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878441.663] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878441.674] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878441.706] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878441.717] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878441.728] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878441.757] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878441.760] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878441.765] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878441.770] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878441.792] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [1878441.799] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [1878441.856] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.867] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.889] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.896] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.907] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.917] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878441.937] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878441.944] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878442.054] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878442.065] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878442.106] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878442.116] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878442.127] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878442.139] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878442.161] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1878442.166] {client} server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1878442.171] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878442.191] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1878442.202] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1878442.207] {proxy } client#2    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1878442.209] {proxy } server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1878442.213] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878442.219] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878442.250] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878442.259] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878442.269] {server} client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1878442.280] {server} client#2    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1878442.283] {server} client#2    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1878442.294] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878442.300] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878442.304] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878442.509] {proxy } server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1878442.514] {proxy } client#2    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1878442.524] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878442.527] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878442.531] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878442.537] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878442.562] {client} server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1878442.566] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878442.569] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878442.585] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1878442.589] {client} server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1878442.594] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1878442.614] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1878442.622] {proxy } client#2    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1878442.625] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1878442.631] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878442.653] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878442.659] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878442.664] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878443.073] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878443.101] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878443.126] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878443.134] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878443.139] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878443.150] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878443.169] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878443.176] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878443.202] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878443.205] {proxy } client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878443.210] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878443.215] {proxy } client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878443.232] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878443.235] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878443.247] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [1878443.250] {client} server      <= wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [1878443.259] {client} server      <= wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [1878443.274] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [1878443.280] {proxy } client#2    -> wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [2026-03-30T09:25:53Z WARN  wl_proxy::protocol_helpers] Could not forward a wlproxy_test_non_forward.echo message: the receiver has no server id
[INFO] [stderr] [1878443.341] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [1878443.354] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878443.386] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878443.392] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878443.396] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878443.425] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878443.440] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878443.447] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878443.472] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878443.475] {proxy } client#2    <= wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [1878443.479] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878443.482] {proxy } client#2    <= wl_display#1.delete_id(id: 7)
[INFO] [stderr] [1878443.497] {client} server      -> wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [1878443.501] {client} server      -> wl_display#1.delete_id(id: 7)
[INFO] [stderr] [1878443.512] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [1878443.515] {client} server      <= wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [1878443.522] {client} server      <= wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [1878443.534] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [1878443.540] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1878443.543] {proxy } client#2    -> wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [1878443.545] {proxy } server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1878443.548] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [1878443.555] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1878443.579] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878443.587] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878443.596] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878443.618] {server} client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1878443.624] {server} client#2    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1878443.626] {server} client#2    <= wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [1878443.630] {server} client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1878443.634] {server} client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878443.638] {server} client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878443.660] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878443.663] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878443.666] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878443.670] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878443.685] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#50)
[INFO] [stderr] [1878443.736] {proxy } server      -> wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [1878443.739] {proxy } client#2    <= wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [1878443.743] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1878443.746] {proxy } client#2    <= wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [1878443.749] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1878443.753] {proxy } client#2    <= wl_display#1.delete_id(id: 8)
[INFO] [stderr] [1878443.769] {client} server      -> wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [1878443.772] {client} server      -> wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [1878443.775] {client} server      -> wl_display#1.delete_id(id: 8)
[INFO] [stderr] [1878444.408] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878444.424] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878444.447] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878444.454] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878444.467] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878444.477] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878444.929] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878444.940] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878444.962] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878444.969] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878444.974] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878444.984] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878444.994] {client} server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [1878445.001] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.017] {proxy } client#2    -> wlproxy_test#3.send_object()
[INFO] [stderr] [1878445.020] {proxy } server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [1878445.023] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.033] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.060] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878445.067] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878445.074] {server} client#2    -> wlproxy_test#3.send_object()
[INFO] [stderr] [1878445.102] {server} client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1878445.116] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.121] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.125] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.157] {proxy } server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1878445.164] {proxy } client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1878445.175] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.177] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.181] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.185] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.202] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1878445.207] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.210] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.219] {client} server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1878445.224] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.238] {proxy } client#2    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1878445.241] {proxy } server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1878445.244] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.249] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.266] {server} client#2    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1878445.269] {server} client#2    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1878445.276] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878445.280] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.284] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.307] {proxy } server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1878445.310] {proxy } client#2    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1878445.316] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.318] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.321] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.325] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.339] {client} server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1878445.343] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878445.346] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878445.807] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878445.818] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878445.848] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878445.855] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878445.861] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878445.871] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878446.341] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878446.354] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878446.379] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878446.387] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878446.394] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878446.407] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878446.431] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878446.439] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878446.959] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878446.971] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878446.996] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878447.004] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878447.012] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878447.024] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878447.060] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878447.069] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::duplicate_generated_client_id ... ok
[INFO] [stdout] test object::tests::get_handler ... ok
[INFO] [stdout] test object::tests::forward ... ok
[INFO] [stdout] test object::tests::request_without_server ... ok
[INFO] [stdout] test object::tests::server_destroyed ... ok
[INFO] [stdout] test object::tests::server_sent ... ok
[INFO] [stdout] test object::tests::state ... ok
[INFO] [stdout] test object::tests::version ... ok
[INFO] [stderr] [1878448.571] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878448.681] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878448.789] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878448.885] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878448.969] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878449.056] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::destroyed_client ... ok
[INFO] [stdout] test acceptor::tests::test ... FAILED
[INFO] [stdout] test fixed::tests::maximum - should panic ... ok
[INFO] [stdout] test fixed::tests::minimum - should panic ... ok
[INFO] [stdout] test handler::tests::multi_borrow - should panic ... ok
[INFO] [stdout] test object::tests::duplicate_server_id - should panic ... ok
[INFO] [stdout] test state::tests::acceptor ... FAILED
[INFO] [stderr] [1878459.916] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878460.010] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::count_hops ... ok
[INFO] [stdout] test object::tests::invalid_server_id - should panic ... ok
[INFO] [stdout] test object::tests::wrong_downcast - should panic ... ok
[INFO] [stdout] test poll::tests::test ... ok
[INFO] [stderr] [1878461.525] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878461.547] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878461.573] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878461.583] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878461.601] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878461.613] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878461.626] {proxy } client#2    <= wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [1878461.654] {client} server      -> wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [1878463.134] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878463.146] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878463.156] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878463.171] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878463.191] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878463.214] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878463.223] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878466.265] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878466.277] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878466.300] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878466.307] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878466.321] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878466.332] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878466.376] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878466.391] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878466.510] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878466.527] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878466.537] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878466.547] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878466.557] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878466.585] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878466.588] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878466.598] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878466.603] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878484.171] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::destroyed_readable ... ok
[INFO] [stderr] [1878484.190] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test poll::tests::many ... ok
[INFO] [stderr] [1878484.216] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::display_error ... ok
[INFO] [stderr] [1878484.225] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test poll::tests::edge_trigger ... ok
[INFO] [stderr] [1878484.234] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::add_client ... ok
[INFO] [stderr] [1878484.251] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::closed_client ... ok
[INFO] [stderr] [1878484.266] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::destructor ... ok
[INFO] [stderr] [1878484.270] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stdout] test state::tests::remote_destructor ... ok
[INFO] [stderr] [1878484.278] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stdout] test state::tests::suspend2 ... ok
[INFO] [stderr] [1878484.279] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::suspend5 ... ok
[INFO] [stderr] [1878484.283] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1878484.292] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1878484.306] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.315] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.325] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878484.326] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.336] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878484.339] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.366] {client} server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1878484.372] {client} server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1878484.375] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878484.387] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1878484.393] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1878484.396] {proxy } client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1878484.408] {proxy } server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1878484.413] {proxy } client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1878484.414] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1878484.418] {proxy } server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1878484.423] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1878484.430] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1878484.451] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1878484.461] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1878484.471] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1878484.537] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.539] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.549] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.550] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.574] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.574] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.582] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.582] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.589] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.589] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.601] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.602] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.644] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878484.652] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1878484.651] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.663] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.673] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878484.681] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878484.716] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878484.852] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.852] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.864] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.890] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.899] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.933] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878484.909] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.946] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.957] {server} client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1878484.961] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878484.967] {server} client#2    <= wlproxy_test_hops#4.count(count: 1)
[INFO] [stderr] [1878484.975] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878484.982] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878484.989] {server} client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1878484.994] {server} client#2    <= wlproxy_test_hops#5.count(count: 1)
[INFO] [stderr] [1878484.997] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878484.998] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878485.008] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878485.031] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.033] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.038] {proxy } server      -> wlproxy_test_hops#4.count(count: 1)
[INFO] [stderr] [1878485.041] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.043] {proxy } client#2    <= wlproxy_test_hops#4.count(count: 2)
[INFO] [stderr] [1878485.051] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.057] {proxy } client#3    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.059] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.065] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#4)
[INFO] [stderr] [1878485.070] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.070] {proxy } client#3    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.070] {client} server      -> wlproxy_test_hops#4.count(count: 2)
[INFO] [stderr] [1878485.080] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.124] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878485.079] {proxy } server      <= wl_registry#4.bind(name: 0, id: wlproxy_test#5 (version: 1))
[INFO] [stderr] [2026-03-30T09:25:53Z INFO  wl_proxy::state::tests] unsuspend
[INFO] [stderr] [1878485.161] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878485.166] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878485.168] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.172] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1878485.176] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.177] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1878485.184] {proxy } server      -> wlproxy_test_hops#5.count(count: 1)
[INFO] [stderr] [1878485.186] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1878485.187] {proxy } client#2    <= wlproxy_test_hops#5.count(count: 2)
[INFO] [stderr] [1878485.193] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x78)
[INFO] [stderr] [1878485.199] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x79)
[INFO] [stderr] [1878485.208] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.213] {client} server      -> wlproxy_test_hops#5.count(count: 2)
[INFO] [stderr] [1878485.223] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x78)
[INFO] [stderr] [1878485.234] {proxy } client#3    <= wlproxy_test_array_echo#4.array(array: 0x78)
[INFO] [stderr] [1878485.248] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x79)
[INFO] [stderr] [1878485.254] {proxy } client#3    <= wlproxy_test_array_echo#5.array(array: 0x79)
[INFO] [stderr] [1878485.263] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878485.270] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878485.291] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.293] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878485.301] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.304] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x78)
[INFO] [stderr] [1878485.307] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x79)
[INFO] [stderr] [1878485.311] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878485.318] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x7a)
[INFO] [stderr] [1878485.320] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878485.332] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.337] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x7a)
[INFO] [stderr] [1878485.343] {proxy } client#3    <= wlproxy_test_array_echo#6.array(array: 0x7a)
[INFO] [stderr] [1878485.361] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x7a)
[INFO] [stderr] [1878485.382] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1878485.389] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1878485.408] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1878485.421] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1878485.427] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1878485.439] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1878485.445] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1878485.467] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1878485.471] {client} server      -> wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1878485.480] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878485.484] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878485.491] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.496] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.613] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.615] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.625] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.628] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.648] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.657] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.656] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.663] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.665] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.672] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.673] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.685] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.696] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1878485.703] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878485.712] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.723] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.731] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1878485.742] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1878485.746] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878485.752] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878485.760] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878485.767] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.781] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878485.789] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878485.798] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stdout] test state::tests::suspend6 ... ok
[INFO] [stderr] [1878485.806] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stdout] test state::tests::suspend1 ... ok
[INFO] [stderr] [1878485.836] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test state::tests::suspend4 ... ok
[INFO] [stderr] [1878485.843] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test state::tests::recursive_dispatch ... ok
[INFO] [stderr] [1878485.848] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test state::tests::suspend3 ... ok
[INFO] [stderr] [1878485.851] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test trans::tests::array ... ok
[INFO] [stderr] [1878485.863] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stdout] test trans::tests::echo_fd ... ok
[INFO] [stderr] [1878485.874] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stdout] test trans::tests::large_message ... ok
[INFO] [stderr] [1878485.879] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stdout] test trans::tests::edge_header ... ok
[INFO] [stderr] [1878485.882] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stdout] test trans::tests::fd ... ok
[INFO] [stderr] [1878485.885] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stdout] test trans::tests::not_word_size ... ok
[INFO] [stderr] [1878485.887] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stdout] test utils::free_list::tests::test ... ok
[INFO] [stderr] [1878485.891] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stdout] test trans::tests::small_message ... ok
[INFO] [stderr] [1878485.896] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test utils::free_list::tests::release_out_of_bounds - should panic ... ok
[INFO] [stderr] [1878485.907] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878485.909] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878485.913] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878485.916] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878485.922] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1878485.933] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878485.934] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1878485.938] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878485.942] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878485.945] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878485.958] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1878485.965] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878485.971] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1878485.979] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1878485.984] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1878485.986] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1878485.990] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878485.991] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1878485.995] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878485.997] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1878486.003] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1878486.008] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1878486.013] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1878486.018] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1878486.019] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1878486.023] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.028] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.031] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878486.032] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.037] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.051] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878486.060] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1878486.063] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1878486.068] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.072] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.077] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.076] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878486.079] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.098] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.102] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.104] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878486.118] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878486.122] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1878486.127] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.131] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.131] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878486.139] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.152] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1878486.156] {client} server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 48, fd2: 53)
[INFO] [stderr] [1878486.159] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.164] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.176] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1878486.183] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1878486.188] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.193] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.214] {proxy } client#2    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 4, fd2: 12)
[INFO] [stderr] [1878486.220] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1878486.227] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1878486.233] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.233] {proxy } server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 4, fd2: 12)
[INFO] [stderr] [1878486.238] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.240] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.243] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.246] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.246] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.272] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1878486.275] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1878486.288] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.292] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.294] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878486.298] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.300] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.304] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.304] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878486.307] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.314] {server} client#2    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 4, fd2: 12)
[INFO] [stderr] [1878486.324] {server} client#2    <= wlproxy_test_fd_echo#4.fd(fd1: 4, fd2: 12)
[INFO] [stderr] [1878486.325] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1878486.329] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.333] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.335] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.347] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.348] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1878486.354] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.354] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.359] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.363] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.368] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1878486.375] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1878486.379] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.384] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.402] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1878486.408] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1878486.413] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.424] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.428] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.432] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.456] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1878486.460] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1878486.465] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.469] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.473] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.476] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.479] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.483] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.500] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1878486.504] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.508] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.510] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.522] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1878486.528] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.541] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1878486.548] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1878486.552] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.557] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.573] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1878486.578] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1878486.583] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.588] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.592] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.596] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test utils::stack::tests::stack ... ok
[INFO] [stderr] [1878486.619] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stdout] test utils::stash::tests::test ... ok
[INFO] [stderr] [1878486.629] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1878486.634] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.638] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.643] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.645] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.649] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.652] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.677] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1878486.681] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.685] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.687] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.699] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1878486.705] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.723] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1878486.730] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1878486.735] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.740] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.757] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1878486.763] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1878486.769] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.774] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1878486.778] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.782] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.804] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1878486.808] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1878486.813] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.817] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.822] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.824] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.834] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.838] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878486.854] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1878486.859] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878486.863] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878486.866] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878487.163] {proxy } server      -> wlproxy_test_fd_echo#4.fd(fd1: 11, fd2: 35)
[INFO] [stderr] [1878487.169] {proxy } client#2    <= wlproxy_test_fd_echo#4.fd(fd1: 11, fd2: 35)
[INFO] [stderr] [1878487.184] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878487.189] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878487.195] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878487.197] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878487.202] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878487.206] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878487.239] {client} server      -> wlproxy_test_fd_echo#4.fd(fd1: 11, fd2: 35)
[INFO] [stderr] [1878487.254] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878487.259] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1878487.262] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1878487.265] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878487.275] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878487.295] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878487.304] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878487.310] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878487.322] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878487.345] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878487.353] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878487.380] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:25:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [1878489.468] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878489.491] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878489.513] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878489.530] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878489.538] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878489.550] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878489.576] {client} server      <= wlproxy_test#3.recv_fd(fd: 19)
[INFO] [stderr] [1878489.589] {client} server      <= wlproxy_test#3.recv_fd(fd: 19)
[INFO] [stderr] [1878489.598] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878489.648] {proxy } client#2    -> wlproxy_test#3.recv_fd(fd: 4)
[INFO] [stderr] [1878489.659] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 4)
[INFO] [stderr] [1878489.687] {proxy } client#2    -> wlproxy_test#3.recv_fd(fd: 4)
[INFO] [stderr] [1878489.698] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 4)
[INFO] [stderr] [1878489.703] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878489.721] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878494.058] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878494.076] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878494.121] {server} client#2    -> wlproxy_test#3.recv_fd(fd: 12)
[INFO] [stderr] [1878494.150] {server} client#2    -> wlproxy_test#3.recv_fd(fd: 12)
[INFO] [stderr] [1878494.163] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1878494.174] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878494.188] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878494.237] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878494.242] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878494.251] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878494.267] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878494.294] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1878494.298] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1878497.556] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878497.573] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878497.598] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878497.611] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878497.619] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878497.630] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878497.650] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:25:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 9 that is not a multiple of 4
[INFO] [stderr] [1878498.797] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878498.817] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878498.843] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878498.851] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1878498.858] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878498.869] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1878498.891] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:25:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 4 < 8
[INFO] [stdout] test state::tests::many_events ... ok
[INFO] [stdout] test trans::tests::many_messages_with_fd ... ok
[INFO] [stdout] test trans::tests::many_messages ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- acceptor::tests::test stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'acceptor::tests::test' (17) panicked at src/acceptor/tests.rs:9:46:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: AcceptorError(XrdNotSet)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5c5ee05f2afa - std[f92b4c606f291077]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x5c5ee05f2afa - std[f92b4c606f291077]::backtrace_rs::backtrace::trace_unsynchronized::<std[f92b4c606f291077]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x5c5ee05f2afa - std[f92b4c606f291077]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x5c5ee05f2afa - <<std[f92b4c606f291077]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[786f478f706679df]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x5c5ee060aaca - <core[786f478f706679df]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x5c5ee060aaca - core[786f478f706679df]::fmt::write
[INFO] [stdout]    6:     0x5c5ee05f8af2 - std[f92b4c606f291077]::io::default_write_fmt::<alloc[64763625b5a07cdb]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x5c5ee05f8af2 - <alloc[64763625b5a07cdb]::vec::Vec<u8> as std[f92b4c606f291077]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x5c5ee05d1a5f - <std[f92b4c606f291077]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x5c5ee05d1a5f - std[f92b4c606f291077]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x5c5ee05eaf59 - std[f92b4c606f291077]::panicking::default_hook
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x5c5ee058092c - <alloc[64763625b5a07cdb]::boxed::Box<dyn for<'a, 'b> core[786f478f706679df]::ops::function::Fn<(&'a std[f92b4c606f291077]::panic::PanicHookInfo<'b>,), Output = ()> + core[786f478f706679df]::marker::Sync + core[786f478f706679df]::marker::Send> as core[786f478f706679df]::ops::function::Fn<(&std[f92b4c606f291077]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x5c5ee058092c - test[20e1f0ae6cad7a17]::test_main_with_exit_callback::<test[20e1f0ae6cad7a17]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x5c5ee05eb112 - <alloc[64763625b5a07cdb]::boxed::Box<dyn for<'a, 'b> core[786f478f706679df]::ops::function::Fn<(&'a std[f92b4c606f291077]::panic::PanicHookInfo<'b>,), Output = ()> + core[786f478f706679df]::marker::Sync + core[786f478f706679df]::marker::Send> as core[786f478f706679df]::ops::function::Fn<(&std[f92b4c606f291077]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x5c5ee05eb112 - std[f92b4c606f291077]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x5c5ee05d1b18 - std[f92b4c606f291077]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x5c5ee05c9409 - std[f92b4c606f291077]::sys::backtrace::__rust_end_short_backtrace::<std[f92b4c606f291077]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x5c5ee05d294d - __rustc[8241495c18a89d70]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x5c5ee060b33c - core[786f478f706679df]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x5c5ee060b082 - core[786f478f706679df]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x5c5ee026851a - <core[786f478f706679df]::result::Result<alloc[64763625b5a07cdb]::rc::Rc<wl_proxy[cd803312dc9cde4d]::acceptor::Acceptor>, wl_proxy[cd803312dc9cde4d]::acceptor::AcceptorError>>::unwrap
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x5c5ee026851a - wl_proxy[cd803312dc9cde4d]::acceptor::tests::test
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:9:46
[INFO] [stdout]   22:     0x5c5ee025b9a7 - wl_proxy[cd803312dc9cde4d]::acceptor::tests::test::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:8:10
[INFO] [stdout]   23:     0x5c5ee0236a26 - <wl_proxy[cd803312dc9cde4d]::acceptor::tests::test::{closure#0} as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x5c5ee0574a0b - <fn() -> core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x5c5ee0574a0b - test[20e1f0ae6cad7a17]::__rust_begin_short_backtrace::<core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>, fn() -> core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x5c5ee05813fb - test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x5c5ee05813fb - <core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   28:     0x5c5ee05813fb - std[f92b4c606f291077]::panicking::catch_unwind::do_call::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}>, core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x5c5ee05813fb - std[f92b4c606f291077]::panicking::catch_unwind::<core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>, core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x5c5ee05813fb - std[f92b4c606f291077]::panic::catch_unwind::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}>, core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x5c5ee05813fb - test[20e1f0ae6cad7a17]::run_test_in_process
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x5c5ee05813fb - test[20e1f0ae6cad7a17]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x5c5ee057cb14 - test[20e1f0ae6cad7a17]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x5c5ee057cb14 - std[f92b4c606f291077]::sys::backtrace::__rust_begin_short_backtrace::<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x5c5ee0584002 - std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked::<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x5c5ee0584002 - <core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   37:     0x5c5ee0584002 - std[f92b4c606f291077]::panicking::catch_unwind::do_call::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x5c5ee0584002 - std[f92b4c606f291077]::panicking::catch_unwind::<(), core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x5c5ee0584002 - std[f92b4c606f291077]::panic::catch_unwind::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x5c5ee0584002 - std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked::<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x5c5ee0584002 - <std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1} as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x5c5ee05f240f - <alloc[64763625b5a07cdb]::boxed::Box<dyn core[786f478f706679df]::ops::function::FnOnce<(), Output = ()> + core[786f478f706679df]::marker::Send> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x5c5ee05f240f - <std[f92b4c606f291077]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x731b12985aa4 - <unknown>
[INFO] [stdout]   45:     0x731b12a12a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- state::tests::acceptor stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'state::tests::acceptor' (130) panicked at src/state/tests.rs:114:49:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: StateError(CreateAcceptor(AcceptorError(XrdNotSet)))
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5c5ee05f2afa - std[f92b4c606f291077]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x5c5ee05f2afa - std[f92b4c606f291077]::backtrace_rs::backtrace::trace_unsynchronized::<std[f92b4c606f291077]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x5c5ee05f2afa - std[f92b4c606f291077]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x5c5ee05f2afa - <<std[f92b4c606f291077]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[786f478f706679df]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x5c5ee060aaca - <core[786f478f706679df]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x5c5ee060aaca - core[786f478f706679df]::fmt::write
[INFO] [stdout]    6:     0x5c5ee05f8af2 - std[f92b4c606f291077]::io::default_write_fmt::<alloc[64763625b5a07cdb]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x5c5ee05f8af2 - <alloc[64763625b5a07cdb]::vec::Vec<u8> as std[f92b4c606f291077]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x5c5ee05d1a5f - <std[f92b4c606f291077]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x5c5ee05d1a5f - std[f92b4c606f291077]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x5c5ee05eaf59 - std[f92b4c606f291077]::panicking::default_hook
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x5c5ee058092c - <alloc[64763625b5a07cdb]::boxed::Box<dyn for<'a, 'b> core[786f478f706679df]::ops::function::Fn<(&'a std[f92b4c606f291077]::panic::PanicHookInfo<'b>,), Output = ()> + core[786f478f706679df]::marker::Sync + core[786f478f706679df]::marker::Send> as core[786f478f706679df]::ops::function::Fn<(&std[f92b4c606f291077]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x5c5ee058092c - test[20e1f0ae6cad7a17]::test_main_with_exit_callback::<test[20e1f0ae6cad7a17]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x5c5ee05eb112 - <alloc[64763625b5a07cdb]::boxed::Box<dyn for<'a, 'b> core[786f478f706679df]::ops::function::Fn<(&'a std[f92b4c606f291077]::panic::PanicHookInfo<'b>,), Output = ()> + core[786f478f706679df]::marker::Sync + core[786f478f706679df]::marker::Send> as core[786f478f706679df]::ops::function::Fn<(&std[f92b4c606f291077]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x5c5ee05eb112 - std[f92b4c606f291077]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x5c5ee05d1b18 - std[f92b4c606f291077]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x5c5ee05c9409 - std[f92b4c606f291077]::sys::backtrace::__rust_end_short_backtrace::<std[f92b4c606f291077]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x5c5ee05d294d - __rustc[8241495c18a89d70]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x5c5ee060b33c - core[786f478f706679df]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x5c5ee060b082 - core[786f478f706679df]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x5c5ee026231f - <core[786f478f706679df]::result::Result<alloc[64763625b5a07cdb]::rc::Rc<wl_proxy[cd803312dc9cde4d]::acceptor::Acceptor>, wl_proxy[cd803312dc9cde4d]::state::StateError>>::unwrap
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x5c5ee026231f - wl_proxy[cd803312dc9cde4d]::state::tests::acceptor
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:114:49
[INFO] [stdout]   22:     0x5c5ee025b2b7 - wl_proxy[cd803312dc9cde4d]::state::tests::acceptor::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:99:14
[INFO] [stdout]   23:     0x5c5ee0235fe6 - <wl_proxy[cd803312dc9cde4d]::state::tests::acceptor::{closure#0} as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x5c5ee0574a0b - <fn() -> core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x5c5ee0574a0b - test[20e1f0ae6cad7a17]::__rust_begin_short_backtrace::<core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>, fn() -> core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x5c5ee05813fb - test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x5c5ee05813fb - <core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   28:     0x5c5ee05813fb - std[f92b4c606f291077]::panicking::catch_unwind::do_call::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}>, core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x5c5ee05813fb - std[f92b4c606f291077]::panicking::catch_unwind::<core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>, core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x5c5ee05813fb - std[f92b4c606f291077]::panic::catch_unwind::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<test[20e1f0ae6cad7a17]::run_test_in_process::{closure#0}>, core[786f478f706679df]::result::Result<(), alloc[64763625b5a07cdb]::string::String>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x5c5ee05813fb - test[20e1f0ae6cad7a17]::run_test_in_process
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x5c5ee05813fb - test[20e1f0ae6cad7a17]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x5c5ee057cb14 - test[20e1f0ae6cad7a17]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x5c5ee057cb14 - std[f92b4c606f291077]::sys::backtrace::__rust_begin_short_backtrace::<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x5c5ee0584002 - std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked::<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x5c5ee0584002 - <core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   37:     0x5c5ee0584002 - std[f92b4c606f291077]::panicking::catch_unwind::do_call::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x5c5ee0584002 - std[f92b4c606f291077]::panicking::catch_unwind::<(), core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x5c5ee0584002 - std[f92b4c606f291077]::panic::catch_unwind::<core[786f478f706679df]::panic::unwind_safe::AssertUnwindSafe<std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x5c5ee0584002 - std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked::<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x5c5ee0584002 - <std[f92b4c606f291077]::thread::lifecycle::spawn_unchecked<test[20e1f0ae6cad7a17]::run_test::{closure#1}, ()>::{closure#1} as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x5c5ee05f240f - <alloc[64763625b5a07cdb]::boxed::Box<dyn core[786f478f706679df]::ops::function::FnOnce<(), Output = ()> + core[786f478f706679df]::marker::Send> as core[786f478f706679df]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x5c5ee05f240f - <std[f92b4c606f291077]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/1f7f8ea0721a3b1eb73e6c6d25cccb371434b320/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x731b12985aa4 - <unknown>
[INFO] [stdout]   45:     0x731b12a12a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     acceptor::tests::test
[INFO] [stdout]     state::tests::acceptor
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 109 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.82s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "a2d9861e0002815a2b26e65667e1a9d249ea8f58b0935219b20ad392688887eb", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "a2d9861e0002815a2b26e65667e1a9d249ea8f58b0935219b20ad392688887eb", kill_on_drop: false }`
[INFO] [stdout] a2d9861e0002815a2b26e65667e1a9d249ea8f58b0935219b20ad392688887eb
